**** dT 0.000 * top TEST ../../../../bin/vinyltest/tests/b00053.vtc starting **** top extmacro def pkg_version=trunk **** top extmacro def pkg_branch=trunk **** top extmacro def pwd=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest **** top extmacro def date(...) **** top extmacro def string(...) **** top extmacro def localhost=127.0.0.1 **** top extmacro def bad_backend=127.0.0.1:33433 **** top extmacro def listen_addr=127.0.0.1:0 **** top extmacro def bad_ip=192.0.2.255 **** top extmacro def topbuild=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub **** top extmacro def topsrc=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/../.. **** top macro def testdir=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest/../../../../bin/vinyltest/tests **** top macro def tmpdir=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0 **** top macro def vtcid=vtc.388988.705662d0 ** top === vtest "Does anything get through Unix domain sockets at all ... * top VTEST Does anything get through Unix domain sockets at all ? ** top === server s1 -listen "${tmpdir}/s1.sock" { **** dT 0.001 ** s1 Starting server **** s1 macro def s1_addr=0.0.0.0 **** s1 macro def s1_port=0 **** s1 macro def s1_sock=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/s1.sock * s1 Listen on /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/s1.sock ** top === vinyl v1 -arg "-a ${tmpdir}/v1.sock -a ${listen_addr}" -vcl+... **** dT 0.002 ** s1 Started on /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/s1.sock (1 iterations) **** dT 0.011 ** v1 Launch *** v1 CMD: cd ${pwd} && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M '127.0.0.1 59259' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -a /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock -a 127.0.0.1:0 *** v1 CMD: cd /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M '127.0.0.1 59259' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -a /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock -a 127.0.0.1:0 **** dT 0.012 *** v1 PID: 389012 **** v1 macro def v1_pid=389012 **** v1 macro def v1_name=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1 **** dT 0.046 *** v1 debug|Warning: mlock() of VSM failed: Not owner *** v1 debug| (1) **** dT 0.049 *** v1 debug|Debug: Version: vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v1 debug| *** v1 debug|Debug: *** v1 debug| Platform: -jsolaris,-sdefault,-sdefault,-hcritbit *** v1 debug| *** v1 debug|200 292 *** v1 debug|----------------------------- *** v1 debug|Vinyl Cache CLI 1.0 *** v1 debug|----------------------------- *** v1 debug|-jsolaris,-sdefault,-sdefault,-hcritbit *** v1 debug|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v1 debug| *** v1 debug|Type 'help' for command list. *** v1 debug|Type 'quit' to close CLI session. *** v1 debug|Type 'start' to launch worker process. *** v1 debug| **** dT 0.147 **** v1 CLIPOLL 1 0x1 0x0 0x0 *** v1 CLI connection fd = 6 *** v1 CLI RX 107 **** v1 CLI RX|secngsonirvmtyblukxlgwmqwrsjxael **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** dT 0.148 **** v1 CLI TX|auth 9210ab0d9154f9677b44b4a1d8566e8ec0008ef77329deee2f59679b0b264fbf *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Vinyl Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|-jsolaris,-sdefault,-sdefault,-hcritbit **** v1 CLI RX|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 **** v1 CLI RX| **** v1 CLI RX|Type 'help' for command list. **** v1 CLI RX|Type 'quit' to close CLI session. **** v1 CLI RX|Type 'start' to launch worker process. **** dT 0.149 **** v1 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P **** v1 CLI TX|vcl 4.1; **** v1 CLI TX|backend s1 { .path = "/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/s1.sock"; } **** v1 CLI TX| **** v1 CLI TX| **** v1 CLI TX|\tsub vcl_backend_response { **** v1 CLI TX|\t\tset beresp.do_stream = false; **** v1 CLI TX|\t} **** v1 CLI TX|\tsub vcl_deliver { **** v1 CLI TX|\t\t# make s_resp_hdrbytes deterministic **** v1 CLI TX|\t\tunset resp.http.via; **** v1 CLI TX|\t} **** v1 CLI TX| **** v1 CLI TX|%XJEIFLH|)Xspa8P **** dT 0.249 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.349 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.449 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.549 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.649 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.749 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.849 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.860 *** v1 CLI RX 200 **** v1 CLI RX|Message from VCC-compiler: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|Message from C-compiler: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|Message from dlopen: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|VCL compiled. **** v1 CLI TX|vcl.use vcl1 *** v1 CLI RX 200 **** v1 CLI RX|VCL 'vcl1' now active ** v1 Start **** v1 CLI TX|start **** dT 0.871 *** v1 debug|Debug: *** v1 debug| Child (389157) Started **** dT 0.903 *** v1 debug|Child launched OK **** dT 0.904 *** v1 debug|Info: Child (389157) said Child starts *** v1 CLI RX 200 *** v1 debug| *** v1 debug|Info: *** v1 wait-running **** v1 CLI TX|status *** v1 debug| Child (389157) said Security: proc_setid missing, uid/gid unchanged *** v1 CLI RX 200 **** v1 CLI RX|Child in state running **** v1 CLI TX|debug.listen_address *** v1 CLI RX 200 **** v1 CLI RX|a0 /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock - **** v1 CLI RX|a1 127.0.0.1 52874 **** v1 CLI TX|debug.xid 1000 *** v1 CLI RX 200 **** v1 CLI RX|XID is 1000 chunk 1 **** v1 CLI TX|debug.listen_address **** dT 0.905 *** v1 CLI RX 200 **** v1 CLI RX|a0 /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock - **** v1 CLI RX|a1 127.0.0.1 52874 ** v1 Listen on 0.0.0.0 0 **** v1 macro def v1_addr=0.0.0.0 **** v1 macro def v1_port=0 **** v1 macro def v1_sock=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 macro def v1_a0_addr=0.0.0.0 **** v1 macro def v1_a0_port=0 **** v1 macro def v1_a0_sock=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 macro def v1_a1_addr=127.0.0.1 **** v1 macro def v1_a1_port=52874 **** v1 macro def v1_a1_sock=127.0.0.1:52874 **** dT 0.950 **** v1 vsl| 0 CLI - Rd vcl.load "vcl1" vcl_vcl1.1773745162.721668/vgc.so 1auto **** v1 vsl| 0 CLI - Wr 200 52 Loaded "vcl_vcl1.1773745162.721668/vgc.so" as "vcl1" **** v1 vsl| 0 CLI - Rd vcl.use "vcl1" **** v1 vsl| 0 CLI - Wr 200 0 **** v1 vsl| 0 CLI - Rd start **** v1 vsl| 0 Debug - sockopt: Setting SO_LINGER for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting SO_KEEPALIVE for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting SO_SNDTIMEO for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting SO_RCVTIMEO for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting TCP_NODELAY for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPIDLE for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPCNT for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPINTVL for a1=127.0.0.1:52874 **** v1 vsl| 0 Debug - sockopt: Setting SO_LINGER for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 0 Debug - sockopt: Setting SO_KEEPALIVE for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 0 Debug - sockopt: Setting SO_SNDTIMEO for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 0 Debug - sockopt: Setting SO_RCVTIMEO for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 0 CLI - Wr 200 0 **** v1 vsl| 0 CLI - Rd debug.listen_address **** v1 vsl| 0 CLI - Wr 200 95 a0 /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock - a1 127.0.0.1 52874 **** v1 vsl| 0 CLI - Rd debug.xid 1000 **** v1 vsl| 0 CLI - Wr 200 19 XID is 1000 chunk 1 **** v1 vsl| 0 CLI - Rd debug.listen_address **** v1 vsl| 0 CLI - Wr 200 95 a0 /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock - a1 127.0.0.1 52874 **** dT 1.005 ** top === vinyl v1 -cliok "param.set debug +workspace" **** v1 CLI TX|param.set debug +workspace *** v1 CLI RX 200 ** v1 CLI 200 ** top === vinyl v1 -cliok "param.set debug +witness" **** v1 CLI TX|param.set debug +witness *** v1 CLI RX 200 ** v1 CLI 200 ** top === vinyl v1 -expect n_object == 0 **** dT 1.007 ** v1 as expected: n_object (0) == 0 (0) ** top === vinyl v1 -expect sess_conn == 0 ** v1 as expected: sess_conn (0) == 0 (0) ** top === vinyl v1 -expect client_req == 0 ** v1 as expected: client_req (0) == 0 (0) ** top === vinyl v1 -expect cache_miss == 0 ** v1 as expected: cache_miss (0) == 0 (0) ** top === client c1 -connect "${v1_sock}" { ** c1 Starting client ** c1 Waiting for client ** c1 Started on /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock (1 iterations) *** c1 Connect to /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock *** c1 connected fd 18 to /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock ** c1 === txreq -url "/" **** c1 txreq|GET / HTTP/1.1\r **** c1 txreq|Host: 127.0.0.1\r **** c1 txreq|User-Agent: c1\r **** c1 txreq|\r ** c1 === rxresp **** dT 1.008 *** s1 accepted fd 4 0.0.0.0 0 ** s1 === rxreq **** dT 1.009 **** s1 rxhdr|GET / HTTP/1.1\r **** s1 rxhdr|Host: 127.0.0.1\r **** s1 rxhdr|User-Agent: c1\r **** s1 rxhdr|X-Forwarded-For: 0.0.0.0\r **** s1 rxhdr|Via: 1.1 v1 (Vinyl-Cache/trunk)\r **** s1 rxhdr|Accept-Encoding: gzip\r **** s1 rxhdr|X-Vinyl: 1002\r **** s1 rxhdr|\r **** s1 rxhdrlen = 148 **** s1 http[ 0] |GET **** s1 http[ 1] |/ **** s1 http[ 2] |HTTP/1.1 **** s1 http[ 3] |Host: 127.0.0.1 **** s1 http[ 4] |User-Agent: c1 **** s1 http[ 5] |X-Forwarded-For: 0.0.0.0 **** s1 http[ 6] |Via: 1.1 v1 (Vinyl-Cache/trunk) **** s1 http[ 7] |Accept-Encoding: gzip **** s1 http[ 8] |X-Vinyl: 1002 **** s1 bodylen = 0 ** s1 === txresp -body "012345\n" **** s1 txresp|HTTP/1.1 200 OK\r **** s1 txresp|Date: Tue, 17 Mar 2026 10:59:23 GMT\r **** s1 txresp|Server: s1\r **** s1 txresp|Content-Length: 7\r **** s1 txresp|\r **** s1 txresp|012345 *** s1 shutting fd 4 (server run) ** s1 Ending **** dT 1.020 **** c1 rxhdr|HTTP/1.1 200 OK\r **** c1 rxhdr|Date: Tue, 17 Mar 2026 10:59:23 GMT\r **** c1 rxhdr|Server: s1\r **** c1 rxhdr|Content-Length: 7\r **** c1 rxhdr|X-Vinyl: 1001\r **** c1 rxhdr|Age: 0\r **** c1 rxhdr|Accept-Ranges: bytes\r **** c1 rxhdr|Connection: keep-alive\r **** c1 rxhdr|\r **** c1 rxhdrlen = 156 **** c1 http[ 0] |HTTP/1.1 **** c1 http[ 1] |200 **** c1 http[ 2] |OK **** c1 http[ 3] |Date: Tue, 17 Mar 2026 10:59:23 GMT **** c1 http[ 4] |Server: s1 **** c1 http[ 5] |Content-Length: 7 **** c1 http[ 6] |X-Vinyl: 1001 **** c1 http[ 7] |Age: 0 **** c1 http[ 8] |Accept-Ranges: bytes **** c1 http[ 9] |Connection: keep-alive **** c1 c-l|012345 **** c1 bodylen = 7 ** c1 === expect resp.status == 200 **** c1 EXPECT resp.status (200) == "200" match *** c1 closing fd 18 ** c1 Ending ** top === vinyl v1 -expect n_object == 1 ** v1 as expected: n_object (1) == 1 (1) ** top === vinyl v1 -expect sess_conn == 1 ** v1 as expected: sess_conn (1) == 1 (1) ** top === vinyl v1 -expect client_req == 1 ** v1 as expected: client_req (1) == 1 (1) ** top === vinyl v1 -expect cache_miss == 1 ** v1 as expected: cache_miss (1) == 1 (1) ** top === vinyl v1 -expect s_sess == 1 ** v1 as expected: s_sess (1) == 1 (1) ** top === vinyl v1 -expect s_resp_bodybytes == 7 ** v1 as expected: s_resp_bodybytes (7) == 7 (7) ** top === vinyl v1 -expect s_resp_hdrbytes == 156 ** v1 as expected: s_resp_hdrbytes (156) == 156 (156) ** top === vinyl v2 -arg "-a ${tmpdir}/v1.sock -b '${bad_backend}'" -st... **** dT 1.030 ** v2 Launch *** v2 CMD: cd ${pwd} && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2 -i v2 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M '127.0.0.1 51142' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -a /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock -b '127.0.0.1:33433' *** v2 CMD: cd /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2 -i v2 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M '127.0.0.1 51142' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -a /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock -b '127.0.0.1:33433' **** dT 1.031 *** v2 PID: 389203 **** v2 macro def v2_pid=389203 **** v2 macro def v2_name=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2 **** dT 1.050 **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS_ReserveSize(wrk, fe09fd70, 272/2044) = 272 **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 272 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 272 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 272 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 272 2044} **** v1 vsl| 0 Debug - WS_Init(ses, 8346544, 834658c, 620) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 0 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 0 0 616} **** v1 vsl| 0 Debug - WS_ReserveSize(ses, 8346544, 36/616) = 36 **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 0 36 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 0 36 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 0 36 616} **** v1 vsl| 0 Debug - WS_Release(ses, 8346544, 36) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 0 616} **** v1 vsl| 0 Debug - WS_ReserveSize(ses, 8346544, 8/580) = 8 **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 8 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 8 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 36 8 616} **** v1 vsl| 0 Debug - WS_Release(ses, 8346544, 8) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 44 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 44 0 616} **** v1 vsl| 0 Debug - WS_ReserveSize(ses, 8346544, 2/572) = 2 **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 44 2 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 44 2 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 44 2 616} **** v1 vsl| 0 Debug - WS_Release(ses, 8346544, 2) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 48 0 616} **** v1 vsl| 1000 Begin c sess 0 HTTP/1 **** v1 vsl| 1000 SessOpen c 0.0.0.0 0 a0 0.0.0.0 0 1773745163.580245 18 **** v1 vsl| 1000 Debug c sockopt: Test confirmed SO_KEEPALIVE non heredity for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: Test confirmed SO_SNDTIMEO non heredity for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: Test confirmed SO_RCVTIMEO non heredity for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: SO_LINGER may be inherited for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: Setting SO_KEEPALIVE for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: Setting SO_SNDTIMEO for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 1000 Debug c sockopt: Setting SO_RCVTIMEO for a0=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock **** v1 vsl| 0 Debug - WS_Init(req, 83468f8, 8348150, 18096) **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 272 2044} **** v1 vsl| 0 Debug - WS_Release(wrk, fe09fd70, 0) **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS_Reset(req, 83468f8, 8348150) **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS_ReserveAll(req, 83468f8) = 18092 **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 48 0 616} **** v1 vsl| 0 Debug - WS_ReserveSize(ses, 8346544, 4/568) = 4 **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 48 4 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 48 4 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 48 4 616} **** v1 vsl| 0 Debug - WS_Release(ses, 8346544, 4) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS_ReleaseP(req, 83468f8, 8348183 (51)) **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 52 0 18092} **** v1 vsl| 1000 Link c req 1001 rxreq **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1002 Begin b bereq 1001 fetch **** v1 vsl| 1002 VCL_use b vcl1 **** v1 vsl| 1002 Timestamp b Start: 1773745163.580863 0.000000 0.000000 **** v1 vsl| 1002 BereqMethod b GET **** v1 vsl| 1002 BereqURL b / **** v1 vsl| 1002 BereqProtocol b HTTP/1.1 **** v1 vsl| 1002 BereqHeader b Host: 127.0.0.1 **** v1 vsl| 1002 BereqHeader b User-Agent: c1 **** v1 vsl| 1002 BereqHeader b X-Forwarded-For: 0.0.0.0 **** v1 vsl| 1002 BereqHeader b Via: 1.1 v1 (Vinyl-Cache/trunk) **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 14168 14168} **** v1 vsl| 1002 Debug b WS_ReserveAll(bo, 834c9e0) = 14168 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 14168 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 14168 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 0 14168 14168} **** v1 vsl| 1002 Debug b WS_Release(bo, 834c9e0, 22) **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 24 0 14168} **** v1 vsl| 1002 BereqHeader b Accept-Encoding: gzip **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 24 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 24 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 4) = 834e25c **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 28 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 28 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 28 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 2) = 834e260 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 32 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 32 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 32 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 9) = 834e264 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 44 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 44 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 44 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 16) = 834e270 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 60 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 60 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 60 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 15) = 834e280 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 76 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 76 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 76 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 25) = 834e290 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 104 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 104 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 104 0 14168} **** v1 vsl| 1002 Debug b WS_Copy(bo, 834c9e0, 32) = 834e2ac **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 0 14168} **** v1 vsl| 1002 Debug b WS_Snapshot(bo, 834c9e0) = 834e2cc **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 14032 14168} **** v1 vsl| 1002 Debug b WS_ReserveAll(bo, 834c9e0) = 14032 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 14032 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 14032 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 136 14032 14168} **** v1 vsl| 1002 Debug b WS_Release(bo, 834c9e0, 14) **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 152 0 14168} **** v1 vsl| 1002 BereqHeader b X-Vinyl: 1002 **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Snapshot(wrk, fe0bfd70) = fe0bf4e0 **** v1 vsl| 1002 VCL_call b BACKEND_FETCH **** v1 vsl| 1002 VCL_return b fetch **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Snapshot(wrk, fe0bfd70) = fe0bf4e0 **** v1 vsl| 1002 Timestamp b Fetch: 1773745163.580947 0.000084 0.000084 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 152 0 14168} **** v1 vsl| 1002 Debug b WS_Alloc(bo, 834c9e0, 60) = 834e2dc **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 212 0 14168} **** v1 vsl| 1002 Timestamp b Connected: 1773745163.581025 0.000162 0.000078 **** v1 vsl| 1002 BackendOpen b 22 s1 0.0.0.0 0 0.0.0.0 0 connect **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Snapshot(wrk, fe0bfd70) = fe0bf4e0 **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Alloc(wrk, fe0bfd70, 68) = fe0bf4e0 **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 68 0 2044} **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 68 0 2044} **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 68 1976 2044} **** v1 vsl| 1002 Debug b WS_ReserveAll(wrk, fe0bfd70) = 1976 **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 68 1976 2044} **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 68 1976 2044} **** v1 vsl| 1002 Debug b WS_Release(wrk, fe0bfd70, 1976) **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 2044 0 2044} **** v1 vsl| 0 Witness - lck_director,vbe_dir_finish,387 lck_conn_pool,VCP_Recycle,376 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 212 0 14168} **** v1 vsl| 1002 Debug b WS_Alloc(bo, 834c9e0, 40) = 834e318 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 0 14168} **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 2044 0 2044} **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 2044 0 2044} **** v1 vsl| 1002 Debug b WS_Reset(wrk, fe0bfd70, fe0bf4e0) **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Timestamp b Bereq: 1773745163.581089 0.000226 0.000063 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS_ReserveAll(bo, 834c9e0) = 13916 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 252 13916 14168} **** v1 vsl| 1002 Debug b WS_ReleaseP(bo, 834c9e0, 834e39e (94)) **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 348 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 348 0 14168} **** v1 vsl| 1002 Debug b WS_Alloc(bo, 834c9e0, 44) = 834e3a0 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 0 14168} **** v1 vsl| 1002 BerespProtocol b HTTP/1.1 **** v1 vsl| 1002 BerespStatus b 200 **** v1 vsl| 1002 BerespReason b OK **** v1 vsl| 1002 BerespHeader b Date: Tue, 17 Mar 2026 10:59:23 GMT **** v1 vsl| 1002 BerespHeader b Server: s1 **** v1 vsl| 1002 BerespHeader b Content-Length: 7 **** v1 vsl| 1002 Timestamp b Beresp: 1773745163.581832 0.000968 0.000742 **** v1 vsl| 1002 TTL b RFC 120 10 0 1773745164 1773745164 1773745163 0 0 cacheable **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Snapshot(wrk, fe0bfd70) = fe0bf4e0 **** v1 vsl| 1002 VCL_call b BACKEND_RESPONSE **** v1 vsl| 1002 VCL_return b deliver **** v1 vsl| 1002 Debug b WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1002 Debug b WS_Snapshot(wrk, fe0bfd70) = fe0bf4e0 **** v1 vsl| 1002 Debug b Missing content-range header or unknown range unit **** v1 vsl| 1002 Timestamp b Process: 1773745163.581896 0.001033 0.000064 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 0 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 13776 14168} **** v1 vsl| 1002 Debug b WS_ReserveAll(bo, 834c9e0) = 13776 **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 13776 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 13776 14168} **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 392 13776 14168} **** v1 vsl| 1002 Debug b WS_Release(bo, 834c9e0, 1) **** v1 vsl| 1002 Debug b WS(bo, 834c9e0) = {834e244 396 0 14168} **** v1 vsl| 1002 Filters b **** v1 vsl| 1002 Storage b umem s0 **** v1 vsl| 1002 Fetch_Body b 3 length - **** v1 vsl| 1002 BackendClose b 22 s1 recycle **** v1 vsl| 1002 Timestamp b BerespBody: 1773745163.592164 0.011301 0.010267 **** v1 vsl| 1002 Length b 7 **** v1 vsl| 1002 BereqAcct b 148 0 148 87 7 94 **** v1 vsl| 1002 End b **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 0 Debug - WS_Reset(wrk, fe0bfd70, fe0bf4e0) **** v1 vsl| 0 Witness - lck_exp,exp_thread,438 lck_wstat,Pool_Sumstat,61 **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 0 Witness - lck_wstat,pool_stat_summ,129 lck_perpool,pool_stat_summ,132 **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 0 Debug - WS_Reset(wrk, fe0bfd70, fe0bf4e0) **** v1 vsl| 0 Debug - WS(wrk, fe0bfd70) = {fe0bf4e0 0 0 2044} **** v1 vsl| 1001 Begin c req 1000 rxreq **** v1 vsl| 1001 Timestamp c Start: 1773745163.580535 0.000000 0.000000 **** v1 vsl| 1001 Timestamp c Req: 1773745163.580535 0.000000 0.000000 **** v1 vsl| 1001 VCL_use c vcl1 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 0 18092} **** v1 vsl| 1001 Debug c WS_Snapshot(req, 83468f8) = 8348184 **** v1 vsl| 1001 Debug c WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1001 Debug c WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1001 Debug c WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1001 Debug c WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1001 ReqStart c 0.0.0.0 0 a0 **** v1 vsl| 1001 ReqMethod c GET **** v1 vsl| 1001 ReqURL c / **** v1 vsl| 1001 ReqProtocol c HTTP/1.1 **** v1 vsl| 1001 ReqHeader c Host: 127.0.0.1 **** v1 vsl| 1001 ReqHeader c User-Agent: c1 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 18040 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 18040 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 18040 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 18040 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 52 18040 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 25) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 0 18092} **** v1 vsl| 1001 ReqHeader c X-Forwarded-For: 0.0.0.0 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 18012 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 18012 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 18012 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 18012 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 80 18012 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 32) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 0 18092} **** v1 vsl| 1001 ReqHeader c Via: 1.1 v1 (Vinyl-Cache/trunk) **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 VCL_call c RECV **** v1 vsl| 1001 VCL_return c hash **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 VCL_call c HASH **** v1 vsl| 1001 VCL_return c lookup **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17980 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 0) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 0 18092} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 VCL_call c MISS **** v1 vsl| 1001 VCL_return c fetch **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 Debug c WS_Init(bo, 834c9e0, 834e244, 14172) **** v1 vsl| 1001 Debug c WS(bo, 834c9e0) = {834e244 0 0 14168} **** v1 vsl| 1001 Link c bereq 1002 fetch **** v1 vsl| 1001 Timestamp c Fetch: 1773745163.592175 0.011639 0.011639 **** v1 vsl| 1001 RespProtocol c HTTP/1.1 **** v1 vsl| 1001 RespStatus c 200 **** v1 vsl| 1001 RespReason c OK **** v1 vsl| 1001 RespHeader c Date: Tue, 17 Mar 2026 10:59:23 GMT **** v1 vsl| 1001 RespHeader c Server: s1 **** v1 vsl| 1001 RespHeader c Content-Length: 7 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17980 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 112 17980 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 14) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 0 18092} **** v1 vsl| 1001 RespHeader c X-Vinyl: 1001 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 17964 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17964 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 17964 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 17964 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 128 17964 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 7) **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 0 18092} **** v1 vsl| 1001 RespHeader c Age: 0 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 17956 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17956 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 17956 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 17956 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 136 17956 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 32) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 0 18092} **** v1 vsl| 1001 RespHeader c Via: 1.1 v1 (Vinyl-Cache/trunk) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 17924 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17924 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 17924 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 17924 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 168 17924 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 21) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 0 18092} **** v1 vsl| 1001 RespHeader c Accept-Ranges: bytes **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 VCL_call c DELIVER **** v1 vsl| 1001 RespUnset c Via: 1.1 v1 (Vinyl-Cache/trunk) **** v1 vsl| 1001 VCL_return c deliver **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 Timestamp c Process: 1773745163.592257 0.011721 0.000082 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 0 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 17900 18092} **** v1 vsl| 1001 Debug c WS_ReserveAll(req, 83468f8) = 17900 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 17900 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 17900 18092} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 192 17900 18092} **** v1 vsl| 1001 Debug c WS_Release(req, 83468f8, 1) **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 196 0 18092} **** v1 vsl| 1001 Filters c **** v1 vsl| 1001 RespHeader c Connection: keep-alive **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Snapshot(wrk, fe09fd70) = fe09f4e0 **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Debug c WS_Alloc(wrk, fe09fd70, 68) = fe09f4e0 **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 68 0 2044} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 68 0 2044} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 68 1976 2044} **** v1 vsl| 1001 Debug c WS_ReserveAll(wrk, fe09fd70) = 1976 **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 68 1976 2044} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 68 1976 2044} **** v1 vsl| 1001 Debug c WS_Release(wrk, fe09fd70, 512) **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 580 0 2044} **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 196 0 18092} **** v1 vsl| 1001 Debug c WS_Alloc(req, 83468f8, 40) = 8348214 **** v1 vsl| 1001 Debug c WS(req, 83468f8) = {8348150 236 0 18092} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 580 0 2044} **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 580 0 2044} **** v1 vsl| 1001 Debug c WS_Reset(wrk, fe09fd70, fe09f4e0) **** v1 vsl| 1001 Debug c WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 1001 Timestamp c Resp: 1773745163.592317 0.011782 0.000060 **** v1 vsl| 1001 ReqAcct c 51 0 51 156 7 163 **** v1 vsl| 1001 End c **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 236 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 236 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 236 0 18092} **** v1 vsl| 0 Debug - WS_Reset(req, 83468f8, 8348150) **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS_ReserveAll(req, 83468f8) = 18092 **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(ses, 8346544) = {834658c 52 0 616} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 18092 18092} **** v1 vsl| 0 Debug - WS_ReleaseP(req, 83468f8, 8348150 (0)) **** v1 vsl| 0 Debug - WS(req, 83468f8) = {8348150 0 0 18092} **** v1 vsl| 1000 SessClose c REM_CLOSE 0.013 **** v1 vsl| 1000 End c **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS_Reset(wrk, fe09fd70, fe09f4e0) **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Witness - lck_wstat,pool_stat_summ,129 lck_perpool,pool_stat_summ,132 **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** v1 vsl| 0 Debug - WS_Reset(wrk, fe09fd70, fe09f4e0) **** v1 vsl| 0 Debug - WS(wrk, fe09fd70) = {fe09f4e0 0 0 2044} **** dT 1.788 *** v2 debug|Warnings: *** v2 debug|Message from VCC-compiler: *** v2 debug|Security: proc_setid missing, uid/gid unchanged *** v2 debug|Message from C-compiler: *** v2 debug|Security: proc_setid missing, uid/gid unchanged *** v2 debug|Message from dlopen: *** v2 debug|Security: proc_setid missing, uid/gid unchanged *** v2 debug| **** dT 1.802 *** v2 debug|Warning: mlock() of VSM failed: Not owner *** v2 debug| (1) **** dT 1.807 *** v2 debug|Debug: Version: vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v2 debug| *** v2 debug|Debug: *** v2 debug| Platform: -jsolaris,-sdefault,-sdefault,-hcritbit *** v2 debug| *** v2 debug|200 292 *** v2 debug|----------------------------- *** v2 debug|Vinyl Cache CLI 1.0 *** v2 debug|----------------------------- *** v2 debug|-jsolaris,-sdefault,-sdefault,-hcritbit *** v2 debug|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v2 debug| *** v2 debug|Type 'help' for command list. *** v2 debug|Type 'quit' to close CLI session. *** v2 debug|Type 'start' to launch worker process. *** v2 debug| **** dT 1.903 **** v2 CLIPOLL 1 0x1 0x0 0x0 *** v2 CLI connection fd = 18 *** v2 CLI RX 107 **** v2 CLI RX|ojnhohehjhvypbczjvhtituiwdmjrgnh **** v2 CLI RX| **** v2 CLI RX|Authentication required. **** dT 1.904 **** v2 CLI TX|auth 2acdca9c50dc0300645e6058a6644f53bd1a9de6ae24eec19a87d46deb7d30dd *** v2 CLI RX 200 **** v2 CLI RX|----------------------------- **** v2 CLI RX|Vinyl Cache CLI 1.0 **** v2 CLI RX|----------------------------- **** v2 CLI RX|-jsolaris,-sdefault,-sdefault,-hcritbit **** v2 CLI RX|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 **** v2 CLI RX| **** v2 CLI RX|Type 'help' for command list. **** v2 CLI RX|Type 'quit' to close CLI session. **** v2 CLI RX|Type 'start' to launch worker process. ** v2 Start **** v2 CLI TX|start **** dT 1.915 *** v2 debug|Debug: *** v2 debug| Child (389318) Started **** dT 1.943 *** v2 debug|Error: Child failed on launch *** v2 debug| *** v2 debug|Error: Child (389318) said Child starts *** v2 debug| *** v2 debug|Error: *** v2 debug| Child (389318) said Security: proc_setid missing, uid/gid unchanged *** v2 debug| **** dT 2.005 **** v2 vsl| 0 Debug - Create worker thread failed 11 Resource temporarily unavailable **** dT 2.043 *** v2 debug|Error: Child (389318) died signal=6 *** v2 debug| *** v2 debug|Error: *** v2 debug|Child (389318) Panic at: Tue, 17 Mar 2026 10:59:24 GMT *** v2 debug|Wrong turn at ../../../../bin/vinyld/cache/cache_wrk.c:121: *** v2 debug|pthread_create(thr, ((void *)0), wrk_bgthread, bt) failed *** v2 debug|version = vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4, vrt api = 23.0 *** v2 debug|ident = -jsolaris,-sdefault,-sdefault,-hcritbit,ports *** v2 debug|now = 5957241.533419 (mono), 1773745164.514524 (real) *** v2 debug|Backtrace: *** v2 debug| 8149fb3: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'vbt_execinfo+0x39 [0x8149fb3] *** v2 debug| 814a1c4: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VBT_format+0x2d [0x814a1c4] *** v2 debug| 80aecdd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_backtrace+0x34 [0x80aecdd] *** v2 debug| 80af020: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_ic+0x27c [0x80af020] *** v2 debug| 81495b9: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VAS *** v2 debug|_Fail+0x3a [0x81495b9] *** v2 debug| 80d93dd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'WRK_BgThread+0xa6 [0x80d93dd] *** v2 debug| 8094ece: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'EXP_Init+0xd9 [0x8094ece] *** v2 debug| 80a8fbb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'child_main+0x356 [0x80a8fbb] *** v2 debug| 80f805e: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_launch_child+0x3f8 [0x80f805e] *** v2 debug| 80f8e52: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mch_cli_server_start+0x28 [0x80f8e52] *** v2 debug| 814b159: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_dispatch+0x2ec [0x814b159] *** v2 debug| 814b3cb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_exec+0x260 [0x814b3cb] *** v2 debug| 814b8a8: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache *** v2 debug|/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_feed+0x392 [0x814b8a8] *** v2 debug| 814c846: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VCLS_Poll+0x2a4 [0x814c846] *** v2 debug| 80f9b14: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_cli_callback2+0x1d [0x80f9b14] *** v2 debug| 814ed4d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Once+0x41d [0x814ed4d] *** v2 debug| 814e74d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Loop+0xb7 [0x814e74d] *** v2 debug| 8100131: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'main+0x17b5 [0x8100131] *** v2 debug| 80728bb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start_crt+0x9a [0x80728bb] *** v2 debug| 807278a: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start+0x1a [0x807278a] *** v2 debug|errno = 11 (Resource tempora *** v2 debug|rily unavailable) *** v2 debug|argv = { *** v2 debug| [0] = \"vinyld\", *** v2 debug| [1] = \"-d\", *** v2 debug| [2] = \"-n\", *** v2 debug| [3] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2\", *** v2 debug| [4] = \"-i\", *** v2 debug| [5] = \"v2\", *** v2 debug| [6] = \"-l\", *** v2 debug| [7] = \"2m\", *** v2 debug| [8] = \"-p\", *** v2 debug| [9] = \"auto_restart=off\", *** v2 debug| [10] = \"-p\", *** v2 debug| [11] = \"syslog_cli_traffic=off\", *** v2 debug| [12] = \"-p\", *** v2 debug| [13] = \"thread_pool_min=10\", *** v2 debug| [14] = \"-p\", *** v2 debug| [15] = \"debug=+vtc_mode\", *** v2 debug| [16] = \"-p\", *** v2 debug| [17] = \"vsl_mask=+Debug,+H2RxHdr,+H2RxBody\", *** v2 debug| [18] = \"-p\", *** v2 debug| [19] = \"h2_initial_window_size=1m\", *** v2 debug| [20] = \"-p\", *** v2 debug| [21] = \"h2_rx_window_low_water=64k\", *** v2 debug| [22] = \"-M\", *** v2 debug| [23] = \"127.0.0.1 51142\", *** v2 debug| [24] = \"-P\", *** v2 debug| [25] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2/vinyld.pid\", *** v2 debug| [26] = \"-p\", *** v2 debug| [27] = \"vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs:\", *** v2 debug| [28] = \"-a\", *** v2 debug| [29] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock\", *** v2 debug| [30] = \"-b\", *** v2 debug| [31] = \"127.0.0.1: *** v2 CLI RX 400 **** v2 CLI RX|Child failed on launch *** v2 debug|33433\", *** v2 debug|} *** v2 debug|pthread.self = 1 *** v2 debug|pthread.name = (cache-main) *** v2 debug|thr.req = NULL *** v2 debug|thr.busyobj = NULL *** v2 debug|thr.worker = NULL *** v2 debug|vmods = { *** v2 debug|}, *** v2 debug|pools = { *** v2 debug| pool = 827f100 { *** v2 debug| nidle = 9, *** v2 debug| nthr = 10, *** v2 debug| lqueue = 0 *** v2 debug| }, *** v2 debug|}, *** v2 debug| *** v2 debug| *** v2 debug|Debug: Child cleanup complete **** dT 2.051 **** v1 vsl| 0 Witness - lck_perpool,Pool_Work_Thread,399 lck_vcl,VCL_Rel,132 **** dT 2.053 ---- v2 CLI start command failed: 400 Child failed on launch **** dT 2.054 * top RESETTING after ../../../../bin/vinyltest/tests/b00053.vtc ** s1 Waiting for server (3/-1) ** v1 Wait **** v1 CLI TX|panic.show *** v1 CLI RX 300 **** v1 CLI RX|Child has not panicked or panic has been cleared *** v1 debug|Info: manager stopping child *** v1 debug|Debug: Stopping Child **** dT 2.151 **** v1 vsl| 0 CLI - EOF on CLI connection, worker stops **** dT 2.154 *** v1 debug|Info: Child (389157) said Child dies *** v1 debug| *** v1 debug|Info: *** v1 debug|Child (389157) ended *** v1 debug|Debug: *** v1 debug|Child cleanup complete *** v1 debug|Info: *** v1 debug|manager dies **** v1 STDOUT EOF **** dT 2.251 ** v1 WAIT4 pid=389012 status=0x0000 (user 0.631000 sys 0.128000) **** dT 2.252 ** v2 Wait **** v2 CLI TX|panic.show *** v2 CLI RX 200 **** v2 CLI RX|Child (389318) Panic at: Tue, 17 Mar 2026 10:59:24 GMT **** v2 CLI RX|Wrong turn at ../../../../bin/vinyld/cache/cache_wrk.c:121: **** v2 CLI RX|pthread_create(thr, ((void *)0), wrk_bgthread, bt) failed **** v2 CLI RX|version = vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4, vrt api = 23.0 **** v2 CLI RX|ident = -jsolaris,-sdefault,-sdefault,-hcritbit,ports **** v2 CLI RX|now = 5957241.533419 (mono), 1773745164.514524 (real) **** v2 CLI RX|Backtrace: **** v2 CLI RX| 8149fb3: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'vbt_execinfo+0x39 [0x8149fb3] **** v2 CLI RX| 814a1c4: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VBT_format+0x2d [0x814a1c4] **** v2 CLI RX| 80aecdd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_backtrace+0x34 [0x80aecdd] **** v2 CLI RX| 80af020: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_ic+0x27c [0x80af020] **** v2 CLI RX| 81495b9: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VAS_Fail+0x3a [0x81495b9] **** v2 CLI RX| 80d93dd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'WRK_BgThread+0xa6 [0x80d93dd] **** v2 CLI RX| 8094ece: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'EXP_Init+0xd9 [0x8094ece] **** v2 CLI RX| 80a8fbb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'child_main+0x356 [0x80a8fbb] **** v2 CLI RX| 80f805e: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_launch_child+0x3f8 [0x80f805e] **** v2 CLI RX| 80f8e52: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mch_cli_server_start+0x28 [0x80f8e52] **** v2 CLI RX| 814b159: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_dispatch+0x2ec [0x814b159] **** v2 CLI RX| 814b3cb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_exec+0x260 [0x814b3cb] **** v2 CLI RX| 814b8a8: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_feed+0x392 [0x814b8a8] **** v2 CLI RX| 814c846: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VCLS_Poll+0x2a4 [0x814c846] **** v2 CLI RX| 80f9b14: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_cli_callback2+0x1d [0x80f9b14] **** v2 CLI RX| 814ed4d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Once+0x41d [0x814ed4d] **** v2 CLI RX| 814e74d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Loop+0xb7 [0x814e74d] **** v2 CLI RX| 8100131: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'main+0x17b5 [0x8100131] **** v2 CLI RX| 80728bb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start_crt+0x9a [0x80728bb] **** v2 CLI RX| 807278a: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start+0x1a [0x807278a] **** v2 CLI RX|errno = 11 (Resource temporarily unavailable) **** v2 CLI RX|argv = { **** v2 CLI RX| [0] = \"vinyld\", **** v2 CLI RX| [1] = \"-d\", **** v2 CLI RX| [2] = \"-n\", **** v2 CLI RX| [3] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2\", **** v2 CLI RX| [4] = \"-i\", **** v2 CLI RX| [5] = \"v2\", **** v2 CLI RX| [6] = \"-l\", **** v2 CLI RX| [7] = \"2m\", **** v2 CLI RX| [8] = \"-p\", **** v2 CLI RX| [9] = \"auto_restart=off\", **** v2 CLI RX| [10] = \"-p\", **** v2 CLI RX| [11] = \"syslog_cli_traffic=off\", **** v2 CLI RX| [12] = \"-p\", **** v2 CLI RX| [13] = \"thread_pool_min=10\", **** v2 CLI RX| [14] = \"-p\", **** v2 CLI RX| [15] = \"debug=+vtc_mode\", **** v2 CLI RX| [16] = \"-p\", **** v2 CLI RX| [17] = \"vsl_mask=+Debug,+H2RxHdr,+H2RxBody\", **** v2 CLI RX| [18] = \"-p\", **** v2 CLI RX| [19] = \"h2_initial_window_size=1m\", **** v2 CLI RX| [20] = \"-p\", **** v2 CLI RX| [21] = \"h2_rx_window_low_water=64k\", **** v2 CLI RX| [22] = \"-M\", **** v2 CLI RX| [23] = \"127.0.0.1 51142\", **** v2 CLI RX| [24] = \"-P\", **** v2 CLI RX| [25] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v2/vinyld.pid\", **** v2 CLI RX| [26] = \"-p\", **** v2 CLI RX| [27] = \"vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs:\", **** v2 CLI RX| [28] = \"-a\", **** v2 CLI RX| [29] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.388988.705662d0/v1.sock\", **** v2 CLI RX| [30] = \"-b\", **** v2 CLI RX| [31] = \"127.0.0.1:33433\", **** v2 CLI RX|} **** v2 CLI RX|pthread.self = 1 **** v2 CLI RX|pthread.name = (cache-main) **** v2 CLI RX|thr.req = NULL **** v2 CLI RX|thr.busyobj = NULL **** v2 CLI RX|thr.worker = NULL **** v2 CLI RX|vmods = { **** v2 CLI RX|}, **** v2 CLI RX|pools = { **** v2 CLI RX| pool = 827f100 { **** v2 CLI RX| nidle = 9, **** v2 CLI RX| nthr = 10, **** v2 CLI RX| lqueue = 0 **** v2 CLI RX| }, **** v2 CLI RX|}, **** v2 CLI RX| **** v2 CLI RX| **** dT 2.262 ---- v2 Unexpected panic * top failure during reset # top TEST ../../../../bin/vinyltest/tests/b00053.vtc FAILED (2.265) exit=2 FAIL tests/b00053.vtc (exit status: 2)